07-01 15:46:38 D/ModuleListener: ModuleListener.testStarted(com.google.android.assistant.v4.tvts.TvtsAssistant4Test#testNormalDeviceUsage) on SKBFXYWR0LWD
07-01 15:46:38 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:46:38 D/DeviceHostUtils: apiLevel: 29
07-01 15:46:38 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:46:38 D/DeviceHostUtils: apiLevel: 29
07-01 15:46:38 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:46:38 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.katniss
07-01 15:46:38 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.katniss] with timeout: 2m 0s
07-01 15:46:38 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:46:38 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:46:39 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:46:39 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:46:39 D/RunUtil: Running command null without timeout.
07-01 15:46:39 D/AppRunnerUtils: Checking service: com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService
07-01 15:46:39 D/AppRunnerUtils: Running the following command: dumpsys activity service com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService
07-01 15:46:39 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, dumpsys, activity, service, com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService] with timeout: 2m 0s
07-01 15:46:39 I/AppRunnerUtils: Service PID = 23998
07-01 15:46:39 I/AssistantTestUtils: Waiting for assistant to be ready...
07-01 15:46:39 D/RunUtil: Running command [launch Assistant intent, then check if Assistant is in foreground] without timeout.
07-01 15:46:39 D/AssistantTestUtils: Launching Assistant intent
07-01 15:46:39 D/AppRunnerUtils: Running the following command: am start --es query Weather -p com.google.android.katniss -c android.intent.category.DEFAULT -a android.intent.action.ASSIST
07-01 15:46:39 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, start, --es, query, Weather, -p, com.google.android.katniss, -c, android.intent.category.DEFAULT, -a, android.intent.action.ASSIST] with timeout: 2m 0s
07-01 15:46:39 D/RunUtil: Running command [check if Assistant is in foreground] without timeout.
07-01 15:46:39 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:46:39 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:46:39 I/DeviceStateMonitor: Waiting 359938 ms for device SKBFXYWR0LWD package manager
07-01 15:46:40 I/NativeDeviceStateMonitor: Waiting 359745 ms for device SKBFXYWR0LWD external store
07-01 15:46:42 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
07-01 15:46:47 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.google.android.apps.tvsearch.results.activity.SearchResultActivity.
07-01 15:46:47 D/AssistantTestUtils: Supplier "check if Assistant is in foreground" returned: true
07-01 15:46:47 D/AssistantTestUtils: Supplier "launch Assistant intent, then check if Assistant is in foreground" returned: true
07-01 15:46:47 D/AssistantTestUtils: Assistant successfully launched: true
07-01 15:46:47 D/RunUtil: Running command [logcat -d | grep -E 'AssistantWrapper(Impl)?: Assistant is now running.'] without timeout.
07-01 15:46:48 I/AssistantTestUtils: Assistant ready: true
07-01 15:46:48 D/RunUtil: Running command [launch Assistant intent, then check if Assistant is in foreground] without timeout.
07-01 15:46:48 D/AssistantTestUtils: Launching Assistant intent
07-01 15:46:48 D/AppRunnerUtils: Running the following command: am start --es query Weather -p com.google.android.katniss -c android.intent.category.DEFAULT -a android.intent.action.ASSIST
07-01 15:46:48 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, start, --es, query, Weather, -p, com.google.android.katniss, -c, android.intent.category.DEFAULT, -a, android.intent.action.ASSIST] with timeout: 2m 0s
07-01 15:46:48 D/RunUtil: Running command [check if Assistant is in foreground] without timeout.
07-01 15:46:48 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:46:48 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:46:48 I/DeviceStateMonitor: Waiting 359959 ms for device SKBFXYWR0LWD package manager
07-01 15:46:48 I/NativeDeviceStateMonitor: Waiting 359757 ms for device SKBFXYWR0LWD external store
07-01 15:46:49 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
07-01 15:46:50 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.google.android.apps.tvsearch.results.activity.SearchResultActivity.
07-01 15:46:50 D/AssistantTestUtils: Supplier "check if Assistant is in foreground" returned: true
07-01 15:46:50 D/AssistantTestUtils: Supplier "launch Assistant intent, then check if Assistant is in foreground" returned: true
07-01 15:46:50 D/AssistantTestUtils: Assistant successfully launched: true
07-01 15:46:50 D/RunUtil: Running command [check if metrics file pattern is present] without timeout.
07-01 15:46:50 I/AssistantTestUtils: Checking if file pattern is present: /storage/emulated/0/Download/katniss-primes*
07-01 15:46:50 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, ls, -t, -d, /storage/emulated/0/Download/katniss-primes*] with timeout: 2m 0s
07-01 15:46:50 D/AssistantTestUtils: Supplier "check if metrics file pattern is present" returned: true
07-01 15:46:50 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, ls, -t, -d, /storage/emulated/0/Download/katniss-primes*] with timeout: 2m 0s
07-01 15:46:50 D/AssistantTestUtils: Session-based metrics File: /storage/emulated/0/Download/katniss-primes-2024-06-30T23_46_47.991.txt
07-01 15:46:50 D/NativeDevice: Using 'ls' to check doesFileExist(/storage/emulated/0/Download/katniss-primes-2024-06-30T23_46_47.991.txt)
07-01 15:46:50 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:46:50 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_13119805635528490873.txt] without timeout.
07-01 15:46:50 D/TvtsBaseAssistantTest: Metrics location: /storage/emulated/0/Download/katniss-primes-2024-06-30T23_46_47.991.txt
07-01 15:46:50 D/TvtsBaseAssistantTest: Option enabling successful!
07-01 15:46:50 I/TvtsBaseAssistantTest: Test: NormalDeviceUsageTest
07-01 15:46:50 I/MeasurementPrinter: search_to_query_latency	Measurement Status	query_to_result_latency	Measurement Status	query_to_result_no_server_latency	Measurement Status
07-01 15:46:50 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:46:50 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:46:50 I/DeviceStateMonitor: Waiting 359959 ms for device SKBFXYWR0LWD package manager
07-01 15:46:50 I/NativeDeviceStateMonitor: Waiting 359872 ms for device SKBFXYWR0LWD external store
07-01 15:46:52 D/RunUtil: Running command null without timeout.
07-01 15:46:52 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:46:52 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:46:52 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:46:52 D/RunUtil: Running command null without timeout.
07-01 15:46:52 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
07-01 15:46:52 I/KeyCodeUtils: Sending keyevent KEYCODE_HOME - intValue: 3
07-01 15:46:53 D/AppRunnerUtils: [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
07-01 15:46:53 D/RunUtil: operation failed, waiting for 500 ms
07-01 15:46:53 D/RunUtil: Running command null without timeout.
07-01 15:46:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:46:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:46:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:46:54 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:46:54 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:46:54 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:46:54 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_1533339552568368756.txt] without timeout.
07-01 15:46:54 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:46:54 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:46:54 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:46:54 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:47:05 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:05 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:47:05 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3125.000000
07-01 15:47:05 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 860.000000
07-01 15:47:05 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:47:05 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 288.000000
07-01 15:47:05 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 17.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 7.000000
07-01 15:47:05 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 234.000000
07-01 15:47:05 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2316.000000
07-01 15:47:05 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
07-01 15:47:05 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 79.000000
07-01 15:47:05 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2262.000000
07-01 15:47:05 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 863.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 5.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
07-01 15:47:05 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 26.000000
07-01 15:47:05 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 860.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 58.000000
07-01 15:47:05 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 79.000000
07-01 15:47:05 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:47:05 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 13.000000
07-01 15:47:05 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:05 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:47:05 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3125.000000
07-01 15:47:05 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 860.000000
07-01 15:47:05 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:47:05 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 288.000000
07-01 15:47:05 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 17.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 7.000000
07-01 15:47:05 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 234.000000
07-01 15:47:05 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2316.000000
07-01 15:47:05 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
07-01 15:47:05 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 79.000000
07-01 15:47:05 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2262.000000
07-01 15:47:05 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:47:05 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 863.000000
07-01 15:47:05 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 5.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
07-01 15:47:05 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 26.000000
07-01 15:47:05 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 860.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 58.000000
07-01 15:47:05 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 79.000000
07-01 15:47:05 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 13.000000
07-01 15:47:05 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:05 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:47:05 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3125.000000
07-01 15:47:05 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 860.000000
07-01 15:47:05 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:47:05 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 288.000000
07-01 15:47:05 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 17.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 7.000000
07-01 15:47:05 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 234.000000
07-01 15:47:05 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2316.000000
07-01 15:47:05 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
07-01 15:47:05 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 79.000000
07-01 15:47:05 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2262.000000
07-01 15:47:05 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 863.000000
07-01 15:47:05 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 5.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
07-01 15:47:05 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 26.000000
07-01 15:47:05 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 860.000000
07-01 15:47:05 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 58.000000
07-01 15:47:05 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 79.000000
07-01 15:47:05 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 13.000000
07-01 15:47:05 I/MeasurementPrinter:                    79.0	                OK	                 3125.0	                OK	                            863.0	                OK
07-01 15:47:05 D/RunUtil: Running command null without timeout.
07-01 15:47:05 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:05 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:05 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:05 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:06 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:06 D/RunUtil: Running command null without timeout.
07-01 15:47:06 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:06 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:06 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:47:06 D/RunUtil: Running command null without timeout.
07-01 15:47:06 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:06 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:06 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:47:06 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:47:06 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYWR0LWD package manager
07-01 15:47:06 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:47:07 D/RunUtil: Running command null without timeout.
07-01 15:47:08 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:08 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:08 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:47:08 D/RunUtil: Running command null without timeout.
07-01 15:47:08 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:08 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:08 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:08 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:08 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:47:08 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:08 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_6044618847567549570.txt] without timeout.
07-01 15:47:09 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:47:09 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:47:09 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:47:09 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:47:19 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:19 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:47:19 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3139.000000
07-01 15:47:19 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 812.000000
07-01 15:47:19 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:47:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 256.000000
07-01 15:47:19 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 91.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 7.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:47:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 177.000000
07-01 15:47:19 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2360.000000
07-01 15:47:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 28.000000
07-01 15:47:19 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 93.000000
07-01 15:47:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2318.000000
07-01 15:47:19 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 826.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 17.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 11.000000
07-01 15:47:19 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 34.000000
07-01 15:47:19 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 812.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
07-01 15:47:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 94.000000
07-01 15:47:19 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:47:19 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:47:19 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:19 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:47:19 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3139.000000
07-01 15:47:19 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 812.000000
07-01 15:47:19 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:47:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 256.000000
07-01 15:47:19 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 91.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 7.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:47:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 177.000000
07-01 15:47:19 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2360.000000
07-01 15:47:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 28.000000
07-01 15:47:19 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 93.000000
07-01 15:47:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2318.000000
07-01 15:47:19 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:47:19 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 826.000000
07-01 15:47:19 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 17.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 11.000000
07-01 15:47:19 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 34.000000
07-01 15:47:19 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 812.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
07-01 15:47:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 94.000000
07-01 15:47:19 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:47:19 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:19 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:47:19 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3139.000000
07-01 15:47:19 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 812.000000
07-01 15:47:19 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:47:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 256.000000
07-01 15:47:19 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 91.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 7.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:47:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 177.000000
07-01 15:47:19 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2360.000000
07-01 15:47:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 28.000000
07-01 15:47:19 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 93.000000
07-01 15:47:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2318.000000
07-01 15:47:19 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 826.000000
07-01 15:47:19 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 17.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 11.000000
07-01 15:47:19 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 34.000000
07-01 15:47:19 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 812.000000
07-01 15:47:19 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
07-01 15:47:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 94.000000
07-01 15:47:19 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:47:19 I/MeasurementPrinter:                    94.0	                OK	                 3144.0	                OK	                            826.0	                OK
07-01 15:47:19 D/RunUtil: Running command null without timeout.
07-01 15:47:19 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:20 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:20 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:20 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:20 D/RunUtil: Running command null without timeout.
07-01 15:47:20 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:20 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:20 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:47:20 D/RunUtil: Running command null without timeout.
07-01 15:47:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:21 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:21 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:47:21 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:47:21 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:47:21 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:47:22 D/RunUtil: Running command null without timeout.
07-01 15:47:22 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:22 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:22 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:47:22 D/RunUtil: Running command null without timeout.
07-01 15:47:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:22 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:22 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:47:23 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:23 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_7282087160188725585.txt] without timeout.
07-01 15:47:23 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:47:23 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:47:23 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:47:23 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:47:32 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:32 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:47:32 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3035.000000
07-01 15:47:32 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 801.000000
07-01 15:47:32 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 3.000000
07-01 15:47:32 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 273.000000
07-01 15:47:32 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 11.000000
07-01 15:47:32 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
07-01 15:47:32 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:47:32 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 191.000000
07-01 15:47:32 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2316.000000
07-01 15:47:32 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 31.000000
07-01 15:47:32 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 94.000000
07-01 15:47:32 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2225.000000
07-01 15:47:32 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 803.000000
07-01 15:47:32 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 21.000000
07-01 15:47:32 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 10.000000
07-01 15:47:32 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
07-01 15:47:32 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 802.000000
07-01 15:47:32 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 59.000000
07-01 15:47:32 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 95.000000
07-01 15:47:32 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:47:32 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
07-01 15:47:32 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:33 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:47:33 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3035.000000
07-01 15:47:33 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 801.000000
07-01 15:47:33 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 3.000000
07-01 15:47:33 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 273.000000
07-01 15:47:33 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 11.000000
07-01 15:47:33 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
07-01 15:47:33 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:47:33 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 191.000000
07-01 15:47:33 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2316.000000
07-01 15:47:33 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 31.000000
07-01 15:47:33 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 94.000000
07-01 15:47:33 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2225.000000
07-01 15:47:33 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:47:33 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 803.000000
07-01 15:47:33 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:47:33 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 21.000000
07-01 15:47:33 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 10.000000
07-01 15:47:33 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
07-01 15:47:33 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 802.000000
07-01 15:47:33 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 59.000000
07-01 15:47:33 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 95.000000
07-01 15:47:33 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
07-01 15:47:33 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:33 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:47:33 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3035.000000
07-01 15:47:33 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 801.000000
07-01 15:47:33 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 3.000000
07-01 15:47:33 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 273.000000
07-01 15:47:33 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 11.000000
07-01 15:47:33 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
07-01 15:47:33 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:47:33 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 191.000000
07-01 15:47:33 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2316.000000
07-01 15:47:33 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 31.000000
07-01 15:47:33 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 94.000000
07-01 15:47:33 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2225.000000
07-01 15:47:33 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 803.000000
07-01 15:47:33 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:47:33 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 21.000000
07-01 15:47:33 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 10.000000
07-01 15:47:33 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
07-01 15:47:33 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 802.000000
07-01 15:47:33 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 59.000000
07-01 15:47:33 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 95.000000
07-01 15:47:33 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
07-01 15:47:33 I/MeasurementPrinter:                    95.0	                OK	                 3028.0	                OK	                            803.0	                OK
07-01 15:47:33 D/RunUtil: Running command null without timeout.
07-01 15:47:33 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:33 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:33 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:33 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:34 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:34 D/RunUtil: Running command null without timeout.
07-01 15:47:34 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:34 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:34 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:47:34 D/RunUtil: Running command null without timeout.
07-01 15:47:34 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:34 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:34 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:47:34 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:47:34 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:47:34 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:47:35 D/RunUtil: Running command null without timeout.
07-01 15:47:35 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:35 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:35 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:47:35 D/RunUtil: Running command null without timeout.
07-01 15:47:35 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:36 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:36 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:36 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:36 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:47:36 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:36 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_1504387305090020055.txt] without timeout.
07-01 15:47:36 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:47:36 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:47:36 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:47:37 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:47:47 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:47 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:47:47 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3060.000000
07-01 15:47:47 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 773.000000
07-01 15:47:47 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 301.000000
07-01 15:47:47 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 69.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:47:47 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 210.000000
07-01 15:47:47 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2369.000000
07-01 15:47:47 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 33.000000
07-01 15:47:47 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 99.000000
07-01 15:47:47 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2273.000000
07-01 15:47:47 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 774.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 30.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
07-01 15:47:47 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 9.000000
07-01 15:47:47 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 773.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 61.000000
07-01 15:47:47 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
07-01 15:47:47 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:47:47 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 13.000000
07-01 15:47:47 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:47 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:47:47 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3060.000000
07-01 15:47:47 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 773.000000
07-01 15:47:47 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 301.000000
07-01 15:47:47 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 69.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:47:47 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 210.000000
07-01 15:47:47 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2369.000000
07-01 15:47:47 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 33.000000
07-01 15:47:47 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 99.000000
07-01 15:47:47 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2273.000000
07-01 15:47:47 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:47:47 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 774.000000
07-01 15:47:47 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 30.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
07-01 15:47:47 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 9.000000
07-01 15:47:47 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 773.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 61.000000
07-01 15:47:47 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
07-01 15:47:47 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 13.000000
07-01 15:47:47 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:47 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:47:47 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3060.000000
07-01 15:47:47 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 773.000000
07-01 15:47:47 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 301.000000
07-01 15:47:47 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 69.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:47:47 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 210.000000
07-01 15:47:47 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2369.000000
07-01 15:47:47 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 33.000000
07-01 15:47:47 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 99.000000
07-01 15:47:47 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2273.000000
07-01 15:47:47 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 774.000000
07-01 15:47:47 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 30.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
07-01 15:47:47 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 9.000000
07-01 15:47:47 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 773.000000
07-01 15:47:47 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 61.000000
07-01 15:47:47 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
07-01 15:47:47 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 13.000000
07-01 15:47:47 I/MeasurementPrinter:                   100.0	                OK	                 3047.0	                OK	                            774.0	                OK
07-01 15:47:47 D/RunUtil: Running command null without timeout.
07-01 15:47:47 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:48 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:48 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:48 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:48 D/RunUtil: Running command null without timeout.
07-01 15:47:48 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:48 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:48 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:47:48 D/RunUtil: Running command null without timeout.
07-01 15:47:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:48 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:47:48 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:47:49 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:47:49 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:47:50 D/RunUtil: Running command null without timeout.
07-01 15:47:50 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:50 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:47:50 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:47:50 D/RunUtil: Running command null without timeout.
07-01 15:47:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:47:50 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:47:50 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:47:51 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:47:51 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_17026732761017911100.txt] without timeout.
07-01 15:47:51 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:47:51 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:47:51 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:47:51 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:48:01 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:01 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:48:01 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3317.000000
07-01 15:48:01 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 769.000000
07-01 15:48:01 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 271.000000
07-01 15:48:01 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 75.000000
07-01 15:48:01 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:48:01 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
07-01 15:48:01 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 155.000000
07-01 15:48:01 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2625.000000
07-01 15:48:01 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 36.000000
07-01 15:48:01 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 84.000000
07-01 15:48:01 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2541.000000
07-01 15:48:01 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 772.000000
07-01 15:48:01 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 8.000000
07-01 15:48:01 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 28.000000
07-01 15:48:01 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 28.000000
07-01 15:48:01 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 769.000000
07-01 15:48:01 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 44.000000
07-01 15:48:01 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
07-01 15:48:01 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:48:01 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 12.000000
07-01 15:48:01 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:02 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:48:02 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3317.000000
07-01 15:48:02 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 769.000000
07-01 15:48:02 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 271.000000
07-01 15:48:02 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 75.000000
07-01 15:48:02 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:48:02 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
07-01 15:48:02 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 155.000000
07-01 15:48:02 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2625.000000
07-01 15:48:02 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 36.000000
07-01 15:48:02 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 84.000000
07-01 15:48:02 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2541.000000
07-01 15:48:02 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:48:02 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 772.000000
07-01 15:48:02 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:48:02 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 8.000000
07-01 15:48:02 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 28.000000
07-01 15:48:02 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 28.000000
07-01 15:48:02 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 769.000000
07-01 15:48:02 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 44.000000
07-01 15:48:02 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
07-01 15:48:02 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 12.000000
07-01 15:48:02 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:02 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:48:02 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3317.000000
07-01 15:48:02 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 769.000000
07-01 15:48:02 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 271.000000
07-01 15:48:02 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 75.000000
07-01 15:48:02 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:48:02 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
07-01 15:48:02 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 155.000000
07-01 15:48:02 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2625.000000
07-01 15:48:02 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 36.000000
07-01 15:48:02 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 84.000000
07-01 15:48:02 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2541.000000
07-01 15:48:02 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 772.000000
07-01 15:48:02 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:48:02 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 8.000000
07-01 15:48:02 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 28.000000
07-01 15:48:02 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 28.000000
07-01 15:48:02 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 769.000000
07-01 15:48:02 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 44.000000
07-01 15:48:02 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
07-01 15:48:02 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 12.000000
07-01 15:48:02 I/MeasurementPrinter:                    85.0	                OK	                 3313.0	                OK	                            772.0	                OK
07-01 15:48:02 D/RunUtil: Running command null without timeout.
07-01 15:48:02 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:02 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:02 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:02 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:03 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:03 D/RunUtil: Running command null without timeout.
07-01 15:48:03 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:03 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:03 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:48:03 D/RunUtil: Running command null without timeout.
07-01 15:48:03 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:03 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:03 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:48:03 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:48:03 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:48:03 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:48:04 D/RunUtil: Running command null without timeout.
07-01 15:48:04 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:04 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:04 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:48:04 D/RunUtil: Running command null without timeout.
07-01 15:48:04 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:05 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:05 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:05 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:05 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:48:05 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:05 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_13261809004974784935.txt] without timeout.
07-01 15:48:05 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:48:05 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:48:05 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:48:06 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:48:16 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:16 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:48:16 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3055.000000
07-01 15:48:16 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 794.000000
07-01 15:48:16 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:48:16 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 292.000000
07-01 15:48:16 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 50.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 11.000000
07-01 15:48:16 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 243.000000
07-01 15:48:16 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2281.000000
07-01 15:48:16 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 40.000000
07-01 15:48:16 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 96.000000
07-01 15:48:16 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2246.000000
07-01 15:48:16 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 796.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 19.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 21.000000
07-01 15:48:16 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 10.000000
07-01 15:48:16 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 796.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 41.000000
07-01 15:48:16 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 97.000000
07-01 15:48:16 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:48:16 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
07-01 15:48:16 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:16 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:48:16 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3055.000000
07-01 15:48:16 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 794.000000
07-01 15:48:16 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:48:16 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 292.000000
07-01 15:48:16 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 50.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 11.000000
07-01 15:48:16 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 243.000000
07-01 15:48:16 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2281.000000
07-01 15:48:16 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 40.000000
07-01 15:48:16 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 96.000000
07-01 15:48:16 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2246.000000
07-01 15:48:16 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:48:16 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 796.000000
07-01 15:48:16 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 19.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 21.000000
07-01 15:48:16 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 10.000000
07-01 15:48:16 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 796.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 41.000000
07-01 15:48:16 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 97.000000
07-01 15:48:16 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
07-01 15:48:16 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:16 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:48:16 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3055.000000
07-01 15:48:16 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 794.000000
07-01 15:48:16 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:48:16 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 292.000000
07-01 15:48:16 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 50.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 11.000000
07-01 15:48:16 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 243.000000
07-01 15:48:16 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2281.000000
07-01 15:48:16 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 40.000000
07-01 15:48:16 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 96.000000
07-01 15:48:16 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2246.000000
07-01 15:48:16 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 796.000000
07-01 15:48:16 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 19.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 21.000000
07-01 15:48:16 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 10.000000
07-01 15:48:16 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 796.000000
07-01 15:48:16 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 41.000000
07-01 15:48:16 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 97.000000
07-01 15:48:16 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
07-01 15:48:16 I/MeasurementPrinter:                    97.0	                OK	                 3042.0	                OK	                            796.0	                OK
07-01 15:48:16 D/RunUtil: Running command null without timeout.
07-01 15:48:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:17 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:17 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:17 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:17 D/RunUtil: Running command null without timeout.
07-01 15:48:17 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:17 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:17 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:48:17 D/RunUtil: Running command null without timeout.
07-01 15:48:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:18 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:18 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:48:18 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:48:18 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:48:18 I/NativeDeviceStateMonitor: Waiting 359903 ms for device SKBFXYWR0LWD external store
07-01 15:48:19 D/RunUtil: Running command null without timeout.
07-01 15:48:19 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:19 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:19 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:48:19 D/RunUtil: Running command null without timeout.
07-01 15:48:19 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:19 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:19 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:20 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:20 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:48:20 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:20 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_12143847734540912775.txt] without timeout.
07-01 15:48:20 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:48:20 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:48:20 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:48:20 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:48:30 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:30 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:48:30 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3018.000000
07-01 15:48:30 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 823.000000
07-01 15:48:30 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 0.000000
07-01 15:48:30 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 280.000000
07-01 15:48:30 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 62.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 6.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:48:30 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 242.000000
07-01 15:48:30 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2232.000000
07-01 15:48:30 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 41.000000
07-01 15:48:30 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 99.000000
07-01 15:48:30 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2185.000000
07-01 15:48:30 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 828.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 32.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 9.000000
07-01 15:48:30 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 50.000000
07-01 15:48:30 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 828.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 51.000000
07-01 15:48:30 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
07-01 15:48:30 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:48:30 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
07-01 15:48:30 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:30 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:48:30 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3018.000000
07-01 15:48:30 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 823.000000
07-01 15:48:30 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 0.000000
07-01 15:48:30 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 280.000000
07-01 15:48:30 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 62.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 6.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:48:30 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 242.000000
07-01 15:48:30 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2232.000000
07-01 15:48:30 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 41.000000
07-01 15:48:30 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 99.000000
07-01 15:48:30 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2185.000000
07-01 15:48:30 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:48:30 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 828.000000
07-01 15:48:30 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 32.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 9.000000
07-01 15:48:30 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 50.000000
07-01 15:48:30 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 828.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 51.000000
07-01 15:48:30 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
07-01 15:48:30 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
07-01 15:48:30 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:30 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:48:30 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3018.000000
07-01 15:48:30 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 823.000000
07-01 15:48:30 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 0.000000
07-01 15:48:30 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 280.000000
07-01 15:48:30 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 62.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 6.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:48:30 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 242.000000
07-01 15:48:30 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2232.000000
07-01 15:48:30 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 41.000000
07-01 15:48:30 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 99.000000
07-01 15:48:30 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2185.000000
07-01 15:48:30 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 828.000000
07-01 15:48:30 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 32.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 9.000000
07-01 15:48:30 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 50.000000
07-01 15:48:30 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 828.000000
07-01 15:48:30 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 51.000000
07-01 15:48:30 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
07-01 15:48:30 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
07-01 15:48:30 I/MeasurementPrinter:                   100.0	                OK	                 3013.0	                OK	                            828.0	                OK
07-01 15:48:30 D/RunUtil: Running command null without timeout.
07-01 15:48:30 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:31 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:31 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:31 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:32 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:32 D/RunUtil: Running command null without timeout.
07-01 15:48:32 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:32 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:32 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:48:32 D/RunUtil: Running command null without timeout.
07-01 15:48:32 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:32 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:32 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:48:32 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYWR0LWD boot complete
07-01 15:48:32 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:48:32 I/NativeDeviceStateMonitor: Waiting 359897 ms for device SKBFXYWR0LWD external store
07-01 15:48:33 D/RunUtil: Running command null without timeout.
07-01 15:48:33 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:33 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:33 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:48:33 D/RunUtil: Running command null without timeout.
07-01 15:48:33 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:33 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:33 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:34 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:34 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:48:34 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:34 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_4201189036772689738.txt] without timeout.
07-01 15:48:34 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:48:34 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:48:34 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:48:34 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:48:44 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:44 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:48:44 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 2923.000000
07-01 15:48:44 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 785.000000
07-01 15:48:44 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 13.000000
07-01 15:48:44 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 292.000000
07-01 15:48:44 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 66.000000
07-01 15:48:44 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 5.000000
07-01 15:48:44 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 6.000000
07-01 15:48:44 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 263.000000
07-01 15:48:44 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2203.000000
07-01 15:48:44 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 67.000000
07-01 15:48:44 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 131.000000
07-01 15:48:44 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2135.000000
07-01 15:48:44 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 785.000000
07-01 15:48:44 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 26.000000
07-01 15:48:44 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 41.000000
07-01 15:48:44 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 35.000000
07-01 15:48:44 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 785.000000
07-01 15:48:44 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 53.000000
07-01 15:48:44 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 132.000000
07-01 15:48:44 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:48:44 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
07-01 15:48:44 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:45 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:48:45 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 2923.000000
07-01 15:48:45 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 785.000000
07-01 15:48:45 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 13.000000
07-01 15:48:45 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 292.000000
07-01 15:48:45 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 66.000000
07-01 15:48:45 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 5.000000
07-01 15:48:45 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 6.000000
07-01 15:48:45 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 263.000000
07-01 15:48:45 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2203.000000
07-01 15:48:45 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 67.000000
07-01 15:48:45 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 131.000000
07-01 15:48:45 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2135.000000
07-01 15:48:45 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:48:45 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 785.000000
07-01 15:48:45 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:48:45 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 26.000000
07-01 15:48:45 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 41.000000
07-01 15:48:45 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 35.000000
07-01 15:48:45 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 785.000000
07-01 15:48:45 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 53.000000
07-01 15:48:45 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 132.000000
07-01 15:48:45 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
07-01 15:48:45 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:45 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:48:45 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 2923.000000
07-01 15:48:45 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 785.000000
07-01 15:48:45 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 13.000000
07-01 15:48:45 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 292.000000
07-01 15:48:45 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 66.000000
07-01 15:48:45 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 5.000000
07-01 15:48:45 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 6.000000
07-01 15:48:45 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 263.000000
07-01 15:48:45 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2203.000000
07-01 15:48:45 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 67.000000
07-01 15:48:45 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 131.000000
07-01 15:48:45 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2135.000000
07-01 15:48:45 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 785.000000
07-01 15:48:45 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:48:45 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 26.000000
07-01 15:48:45 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 41.000000
07-01 15:48:45 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 35.000000
07-01 15:48:45 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 785.000000
07-01 15:48:45 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 53.000000
07-01 15:48:45 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 132.000000
07-01 15:48:45 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
07-01 15:48:45 I/MeasurementPrinter:                   132.0	                OK	                 2920.0	                OK	                            785.0	                OK
07-01 15:48:45 D/RunUtil: Running command null without timeout.
07-01 15:48:45 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:45 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:45 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:45 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:46 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:46 D/RunUtil: Running command null without timeout.
07-01 15:48:46 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:46 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:46 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:48:46 D/RunUtil: Running command null without timeout.
07-01 15:48:46 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:46 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:46 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:48:46 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:48:46 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:48:46 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:48:47 D/RunUtil: Running command null without timeout.
07-01 15:48:47 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:47 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:48:47 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:48:47 D/RunUtil: Running command null without timeout.
07-01 15:48:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:48:48 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:48:48 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:48:48 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:48 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_9455521463612113882.txt] without timeout.
07-01 15:48:48 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:48:48 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:48:48 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:48:49 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:48:59 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:59 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:48:59 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 2940.000000
07-01 15:48:59 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 724.000000
07-01 15:48:59 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 232.000000
07-01 15:48:59 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 47.000000
07-01 15:48:59 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 128.000000
07-01 15:48:59 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2318.000000
07-01 15:48:59 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 15.000000
07-01 15:48:59 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2202.000000
07-01 15:48:59 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 727.000000
07-01 15:48:59 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 13.000000
07-01 15:48:59 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 724.000000
07-01 15:48:59 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 77.000000
07-01 15:48:59 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:48:59 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
07-01 15:48:59 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:59 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:48:59 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 2940.000000
07-01 15:48:59 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 724.000000
07-01 15:48:59 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 232.000000
07-01 15:48:59 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 47.000000
07-01 15:48:59 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 128.000000
07-01 15:48:59 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2318.000000
07-01 15:48:59 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 15.000000
07-01 15:48:59 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2202.000000
07-01 15:48:59 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:48:59 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 727.000000
07-01 15:48:59 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:48:59 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 13.000000
07-01 15:48:59 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 724.000000
07-01 15:48:59 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 77.000000
07-01 15:48:59 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
07-01 15:48:59 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:48:59 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:48:59 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 2940.000000
07-01 15:48:59 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 724.000000
07-01 15:48:59 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 232.000000
07-01 15:48:59 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 47.000000
07-01 15:48:59 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 128.000000
07-01 15:48:59 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2318.000000
07-01 15:48:59 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 15.000000
07-01 15:48:59 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2202.000000
07-01 15:48:59 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 727.000000
07-01 15:48:59 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:48:59 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 13.000000
07-01 15:48:59 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 724.000000
07-01 15:48:59 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 77.000000
07-01 15:48:59 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
07-01 15:48:59 I/MeasurementPrinter:                    77.0	                OK	                 2929.0	                OK	                            727.0	                OK
07-01 15:48:59 D/RunUtil: Running command null without timeout.
07-01 15:48:59 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:00 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:00 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:00 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:00 D/RunUtil: Running command null without timeout.
07-01 15:49:00 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:00 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:00 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:49:00 D/RunUtil: Running command null without timeout.
07-01 15:49:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:00 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:49:00 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:49:01 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYWR0LWD package manager
07-01 15:49:01 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:49:02 D/RunUtil: Running command null without timeout.
07-01 15:49:02 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:02 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:02 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:49:02 D/RunUtil: Running command null without timeout.
07-01 15:49:02 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:02 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:02 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:02 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:02 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:49:03 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:03 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_15324205212074233994.txt] without timeout.
07-01 15:49:03 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:49:03 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:49:03 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:49:03 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:49:13 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:13 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:49:13 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3049.000000
07-01 15:49:13 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 746.000000
07-01 15:49:13 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 302.000000
07-01 15:49:13 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 6.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 7.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 5.000000
07-01 15:49:13 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 257.000000
07-01 15:49:13 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2355.000000
07-01 15:49:13 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 22.000000
07-01 15:49:13 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 82.000000
07-01 15:49:13 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2299.000000
07-01 15:49:13 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 750.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 11.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 11.000000
07-01 15:49:13 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 7.000000
07-01 15:49:13 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 747.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 48.000000
07-01 15:49:13 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 83.000000
07-01 15:49:13 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:49:13 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 28.000000
07-01 15:49:13 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:13 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:49:13 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3049.000000
07-01 15:49:13 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 746.000000
07-01 15:49:13 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 302.000000
07-01 15:49:13 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 6.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 7.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 5.000000
07-01 15:49:13 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 257.000000
07-01 15:49:13 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2355.000000
07-01 15:49:13 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 22.000000
07-01 15:49:13 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 82.000000
07-01 15:49:13 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2299.000000
07-01 15:49:13 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:49:13 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 750.000000
07-01 15:49:13 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 11.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 11.000000
07-01 15:49:13 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 7.000000
07-01 15:49:13 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 747.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 48.000000
07-01 15:49:13 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 83.000000
07-01 15:49:13 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 28.000000
07-01 15:49:13 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:13 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:49:13 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3049.000000
07-01 15:49:13 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 746.000000
07-01 15:49:13 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 302.000000
07-01 15:49:13 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 6.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 7.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 5.000000
07-01 15:49:13 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 257.000000
07-01 15:49:13 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2355.000000
07-01 15:49:13 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 22.000000
07-01 15:49:13 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 82.000000
07-01 15:49:13 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2299.000000
07-01 15:49:13 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 750.000000
07-01 15:49:13 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 11.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 11.000000
07-01 15:49:13 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 7.000000
07-01 15:49:13 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 747.000000
07-01 15:49:13 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 48.000000
07-01 15:49:13 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 83.000000
07-01 15:49:13 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 28.000000
07-01 15:49:13 I/MeasurementPrinter:                    83.0	                OK	                 3049.0	                OK	                            750.0	                OK
07-01 15:49:13 D/RunUtil: Running command null without timeout.
07-01 15:49:14 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:14 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:14 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:14 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:15 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:15 D/RunUtil: Running command null without timeout.
07-01 15:49:15 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:15 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:15 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:49:15 D/RunUtil: Running command null without timeout.
07-01 15:49:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:15 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:49:15 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:49:15 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:49:15 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:49:16 D/RunUtil: Running command null without timeout.
07-01 15:49:16 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:16 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:16 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:49:16 D/RunUtil: Running command null without timeout.
07-01 15:49:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:17 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:17 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:49:17 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:17 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_7149034403844171069.txt] without timeout.
07-01 15:49:17 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:49:17 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:49:17 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:49:17 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:49:28 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:28 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:49:28 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3248.000000
07-01 15:49:28 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 809.000000
07-01 15:49:28 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 5.000000
07-01 15:49:28 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 278.000000
07-01 15:49:28 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 73.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:49:28 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 175.000000
07-01 15:49:28 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2480.000000
07-01 15:49:28 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 20.000000
07-01 15:49:28 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 80.000000
07-01 15:49:28 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2431.000000
07-01 15:49:28 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 810.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 10.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 10.000000
07-01 15:49:28 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 19.000000
07-01 15:49:28 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 810.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
07-01 15:49:28 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 81.000000
07-01 15:49:28 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:49:28 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
07-01 15:49:28 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:28 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:49:28 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3248.000000
07-01 15:49:28 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 809.000000
07-01 15:49:28 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 5.000000
07-01 15:49:28 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 278.000000
07-01 15:49:28 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 73.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:49:28 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 175.000000
07-01 15:49:28 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2480.000000
07-01 15:49:28 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 20.000000
07-01 15:49:28 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 80.000000
07-01 15:49:28 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2431.000000
07-01 15:49:28 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:49:28 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 810.000000
07-01 15:49:28 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 10.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 10.000000
07-01 15:49:28 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 19.000000
07-01 15:49:28 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 810.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
07-01 15:49:28 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 81.000000
07-01 15:49:28 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
07-01 15:49:28 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:28 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:49:28 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3248.000000
07-01 15:49:28 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 809.000000
07-01 15:49:28 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 5.000000
07-01 15:49:28 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 278.000000
07-01 15:49:28 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 73.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:49:28 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 175.000000
07-01 15:49:28 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2480.000000
07-01 15:49:28 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 20.000000
07-01 15:49:28 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 80.000000
07-01 15:49:28 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2431.000000
07-01 15:49:28 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 810.000000
07-01 15:49:28 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 10.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 10.000000
07-01 15:49:28 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 19.000000
07-01 15:49:28 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 810.000000
07-01 15:49:28 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 57.000000
07-01 15:49:28 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 81.000000
07-01 15:49:28 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
07-01 15:49:28 I/MeasurementPrinter:                    81.0	                OK	                 3241.0	                OK	                            810.0	                OK
07-01 15:49:28 D/RunUtil: Running command null without timeout.
07-01 15:49:28 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:29 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:29 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:29 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:29 D/RunUtil: Running command null without timeout.
07-01 15:49:29 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:30 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:30 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:49:30 D/RunUtil: Running command null without timeout.
07-01 15:49:30 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:30 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:30 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:49:30 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:49:30 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:49:30 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:49:31 D/RunUtil: Running command null without timeout.
07-01 15:49:31 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:31 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:31 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:49:31 D/RunUtil: Running command null without timeout.
07-01 15:49:31 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:31 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:31 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:32 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:32 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:49:32 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:32 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_8632670790847239973.txt] without timeout.
07-01 15:49:32 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:49:32 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:49:32 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:49:32 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:49:42 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:42 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:49:42 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3125.000000
07-01 15:49:42 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 810.000000
07-01 15:49:42 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 8.000000
07-01 15:49:42 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 271.000000
07-01 15:49:42 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 57.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 5.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:49:42 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 189.000000
07-01 15:49:42 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2362.000000
07-01 15:49:42 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 41.000000
07-01 15:49:42 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 71.000000
07-01 15:49:42 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2310.000000
07-01 15:49:42 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 813.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 33.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 8.000000
07-01 15:49:42 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 21.000000
07-01 15:49:42 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 812.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 24.000000
07-01 15:49:42 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 72.000000
07-01 15:49:42 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:49:42 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:49:42 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:42 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:49:42 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3125.000000
07-01 15:49:42 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 810.000000
07-01 15:49:42 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 8.000000
07-01 15:49:42 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 271.000000
07-01 15:49:42 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 57.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 5.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:49:42 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 189.000000
07-01 15:49:42 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2362.000000
07-01 15:49:42 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 41.000000
07-01 15:49:42 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 71.000000
07-01 15:49:42 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2310.000000
07-01 15:49:42 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:49:42 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 813.000000
07-01 15:49:42 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 33.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 8.000000
07-01 15:49:42 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 21.000000
07-01 15:49:42 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 812.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 24.000000
07-01 15:49:42 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 72.000000
07-01 15:49:42 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:49:42 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:42 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:49:42 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3125.000000
07-01 15:49:42 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 810.000000
07-01 15:49:42 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 8.000000
07-01 15:49:42 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 271.000000
07-01 15:49:42 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 57.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 5.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:49:42 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 189.000000
07-01 15:49:42 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2362.000000
07-01 15:49:42 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 41.000000
07-01 15:49:42 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 71.000000
07-01 15:49:42 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2310.000000
07-01 15:49:42 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 813.000000
07-01 15:49:42 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 33.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 8.000000
07-01 15:49:42 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 21.000000
07-01 15:49:42 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 812.000000
07-01 15:49:42 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 24.000000
07-01 15:49:42 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 72.000000
07-01 15:49:42 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:49:42 I/MeasurementPrinter:                    72.0	                OK	                 3123.0	                OK	                            813.0	                OK
07-01 15:49:42 D/RunUtil: Running command null without timeout.
07-01 15:49:43 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:43 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:43 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:43 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:44 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:44 D/RunUtil: Running command null without timeout.
07-01 15:49:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:44 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:49:44 D/RunUtil: Running command null without timeout.
07-01 15:49:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:44 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:49:44 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:49:44 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:49:44 I/NativeDeviceStateMonitor: Waiting 359897 ms for device SKBFXYWR0LWD external store
07-01 15:49:45 D/RunUtil: Running command null without timeout.
07-01 15:49:45 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:45 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:45 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:49:45 D/RunUtil: Running command null without timeout.
07-01 15:49:45 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:45 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:45 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:46 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:46 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:49:46 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:46 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_9998933088277840184.txt] without timeout.
07-01 15:49:46 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:49:46 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:49:46 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:49:46 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:49:57 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:57 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:49:57 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3185.000000
07-01 15:49:57 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 790.000000
07-01 15:49:57 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 4.000000
07-01 15:49:57 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 291.000000
07-01 15:49:57 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 61.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 8.000000
07-01 15:49:57 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 215.000000
07-01 15:49:57 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2432.000000
07-01 15:49:57 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 15.000000
07-01 15:49:57 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 86.000000
07-01 15:49:57 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2386.000000
07-01 15:49:57 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 795.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 11.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 4.000000
07-01 15:49:57 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 11.000000
07-01 15:49:57 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 790.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 62.000000
07-01 15:49:57 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 87.000000
07-01 15:49:57 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:49:57 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:49:57 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:57 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:49:57 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3185.000000
07-01 15:49:57 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 790.000000
07-01 15:49:57 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 4.000000
07-01 15:49:57 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 291.000000
07-01 15:49:57 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 61.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 8.000000
07-01 15:49:57 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 215.000000
07-01 15:49:57 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2432.000000
07-01 15:49:57 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 15.000000
07-01 15:49:57 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 86.000000
07-01 15:49:57 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2386.000000
07-01 15:49:57 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:49:57 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 795.000000
07-01 15:49:57 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 11.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 4.000000
07-01 15:49:57 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 11.000000
07-01 15:49:57 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 790.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 62.000000
07-01 15:49:57 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 87.000000
07-01 15:49:57 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:49:57 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:49:57 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:49:57 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3185.000000
07-01 15:49:57 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 790.000000
07-01 15:49:57 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 4.000000
07-01 15:49:57 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 291.000000
07-01 15:49:57 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 61.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 8.000000
07-01 15:49:57 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 215.000000
07-01 15:49:57 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2432.000000
07-01 15:49:57 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 15.000000
07-01 15:49:57 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 86.000000
07-01 15:49:57 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2386.000000
07-01 15:49:57 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 795.000000
07-01 15:49:57 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 11.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 4.000000
07-01 15:49:57 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 11.000000
07-01 15:49:57 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 790.000000
07-01 15:49:57 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 62.000000
07-01 15:49:57 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 87.000000
07-01 15:49:57 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:49:57 I/MeasurementPrinter:                    87.0	                OK	                 3181.0	                OK	                            795.0	                OK
07-01 15:49:57 D/RunUtil: Running command null without timeout.
07-01 15:49:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:58 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:58 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:58 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:49:58 D/RunUtil: Running command null without timeout.
07-01 15:49:58 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:59 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:49:59 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:49:59 D/RunUtil: Running command null without timeout.
07-01 15:49:59 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:59 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:49:59 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:49:59 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:49:59 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:49:59 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:50:00 D/RunUtil: Running command null without timeout.
07-01 15:50:00 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:00 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:00 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:50:00 D/RunUtil: Running command null without timeout.
07-01 15:50:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:01 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:01 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:50:01 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:01 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_5164681833715599842.txt] without timeout.
07-01 15:50:01 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:50:01 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:50:01 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:50:01 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:50:11 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:11 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:50:11 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3071.000000
07-01 15:50:11 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 735.000000
07-01 15:50:11 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 34.000000
07-01 15:50:11 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 326.000000
07-01 15:50:11 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 53.000000
07-01 15:50:11 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:50:11 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
07-01 15:50:11 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 249.000000
07-01 15:50:11 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2368.000000
07-01 15:50:11 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
07-01 15:50:11 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 80.000000
07-01 15:50:11 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2323.000000
07-01 15:50:11 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 736.000000
07-01 15:50:11 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 4.000000
07-01 15:50:11 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 9.000000
07-01 15:50:11 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 16.000000
07-01 15:50:11 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 735.000000
07-01 15:50:11 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 64.000000
07-01 15:50:11 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 82.000000
07-01 15:50:11 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:50:11 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 25.000000
07-01 15:50:11 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:11 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:50:11 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3071.000000
07-01 15:50:11 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 735.000000
07-01 15:50:11 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 34.000000
07-01 15:50:11 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 326.000000
07-01 15:50:11 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 53.000000
07-01 15:50:11 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:50:11 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
07-01 15:50:11 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 249.000000
07-01 15:50:11 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2368.000000
07-01 15:50:11 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
07-01 15:50:11 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 80.000000
07-01 15:50:11 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2323.000000
07-01 15:50:11 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:50:11 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 736.000000
07-01 15:50:11 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:50:11 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 4.000000
07-01 15:50:11 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 9.000000
07-01 15:50:11 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 16.000000
07-01 15:50:11 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 735.000000
07-01 15:50:11 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 64.000000
07-01 15:50:11 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 82.000000
07-01 15:50:11 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 25.000000
07-01 15:50:11 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:12 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:50:12 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3071.000000
07-01 15:50:12 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 735.000000
07-01 15:50:12 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 34.000000
07-01 15:50:12 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 326.000000
07-01 15:50:12 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 53.000000
07-01 15:50:12 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:50:12 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
07-01 15:50:12 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 249.000000
07-01 15:50:12 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2368.000000
07-01 15:50:12 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
07-01 15:50:12 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 80.000000
07-01 15:50:12 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2323.000000
07-01 15:50:12 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 736.000000
07-01 15:50:12 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:50:12 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 4.000000
07-01 15:50:12 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 9.000000
07-01 15:50:12 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 16.000000
07-01 15:50:12 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 735.000000
07-01 15:50:12 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 64.000000
07-01 15:50:12 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 82.000000
07-01 15:50:12 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 25.000000
07-01 15:50:12 I/MeasurementPrinter:                    82.0	                OK	                 3059.0	                OK	                            736.0	                OK
07-01 15:50:12 D/RunUtil: Running command null without timeout.
07-01 15:50:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:12 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:12 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:13 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:13 D/RunUtil: Running command null without timeout.
07-01 15:50:13 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:13 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:13 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:50:13 D/RunUtil: Running command null without timeout.
07-01 15:50:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:13 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:50:13 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:50:13 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:50:13 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:50:14 D/RunUtil: Running command null without timeout.
07-01 15:50:14 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:14 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:14 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:50:14 D/RunUtil: Running command null without timeout.
07-01 15:50:14 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:14 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:15 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:15 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:15 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:50:15 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:15 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_14607411779492967662.txt] without timeout.
07-01 15:50:15 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:50:15 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:50:15 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:50:16 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:50:26 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:26 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:50:26 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3115.000000
07-01 15:50:26 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 754.000000
07-01 15:50:26 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 4.000000
07-01 15:50:26 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 297.000000
07-01 15:50:26 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 48.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 12.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
07-01 15:50:26 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 272.000000
07-01 15:50:26 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2477.000000
07-01 15:50:26 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 31.000000
07-01 15:50:26 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 104.000000
07-01 15:50:26 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2356.000000
07-01 15:50:26 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 756.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 10.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 22.000000
07-01 15:50:26 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
07-01 15:50:26 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 754.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 58.000000
07-01 15:50:26 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 103.000000
07-01 15:50:26 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:50:26 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
07-01 15:50:26 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:26 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:50:26 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3115.000000
07-01 15:50:26 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 754.000000
07-01 15:50:26 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 4.000000
07-01 15:50:26 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 297.000000
07-01 15:50:26 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 48.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 12.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
07-01 15:50:26 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 272.000000
07-01 15:50:26 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2477.000000
07-01 15:50:26 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 31.000000
07-01 15:50:26 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 104.000000
07-01 15:50:26 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2356.000000
07-01 15:50:26 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:50:26 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 756.000000
07-01 15:50:26 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 10.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 22.000000
07-01 15:50:26 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
07-01 15:50:26 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 754.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 58.000000
07-01 15:50:26 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 103.000000
07-01 15:50:26 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
07-01 15:50:26 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:26 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:50:26 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3115.000000
07-01 15:50:26 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 754.000000
07-01 15:50:26 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 4.000000
07-01 15:50:26 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 297.000000
07-01 15:50:26 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 48.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 12.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 2.000000
07-01 15:50:26 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 272.000000
07-01 15:50:26 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2477.000000
07-01 15:50:26 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 31.000000
07-01 15:50:26 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 104.000000
07-01 15:50:26 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2356.000000
07-01 15:50:26 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 756.000000
07-01 15:50:26 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 10.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 22.000000
07-01 15:50:26 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 20.000000
07-01 15:50:26 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 754.000000
07-01 15:50:26 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 58.000000
07-01 15:50:26 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 103.000000
07-01 15:50:26 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 22.000000
07-01 15:50:26 I/MeasurementPrinter:                   103.0	                OK	                 3112.0	                OK	                            756.0	                OK
07-01 15:50:26 D/RunUtil: Running command null without timeout.
07-01 15:50:26 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:27 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:27 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:27 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:27 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:27 D/RunUtil: Running command null without timeout.
07-01 15:50:27 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:28 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:28 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:50:28 D/RunUtil: Running command null without timeout.
07-01 15:50:28 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:28 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:28 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:50:28 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYWR0LWD boot complete
07-01 15:50:28 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYWR0LWD package manager
07-01 15:50:28 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:50:29 D/RunUtil: Running command null without timeout.
07-01 15:50:29 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:29 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:29 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:50:29 D/RunUtil: Running command null without timeout.
07-01 15:50:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:30 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:30 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:50:30 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:30 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_4089899437566534956.txt] without timeout.
07-01 15:50:30 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:50:30 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:50:30 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:50:30 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:50:40 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:40 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:50:40 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3171.000000
07-01 15:50:40 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 764.000000
07-01 15:50:40 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:50:40 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 285.000000
07-01 15:50:40 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 46.000000
07-01 15:50:40 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 180.000000
07-01 15:50:40 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2440.000000
07-01 15:50:40 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 23.000000
07-01 15:50:40 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2404.000000
07-01 15:50:40 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 765.000000
07-01 15:50:40 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 13.000000
07-01 15:50:40 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 764.000000
07-01 15:50:40 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 73.000000
07-01 15:50:40 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:50:40 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
07-01 15:50:40 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:41 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:50:41 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3171.000000
07-01 15:50:41 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 764.000000
07-01 15:50:41 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:50:41 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 285.000000
07-01 15:50:41 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 46.000000
07-01 15:50:41 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 180.000000
07-01 15:50:41 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2440.000000
07-01 15:50:41 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 23.000000
07-01 15:50:41 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2404.000000
07-01 15:50:41 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:50:41 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 765.000000
07-01 15:50:41 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:50:41 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 13.000000
07-01 15:50:41 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 764.000000
07-01 15:50:41 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 73.000000
07-01 15:50:41 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
07-01 15:50:41 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:41 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:50:41 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3171.000000
07-01 15:50:41 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 764.000000
07-01 15:50:41 D/ProtoMeasurementBase: searchbar_state_idle: size = 1, sum: 1.000000
07-01 15:50:41 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 285.000000
07-01 15:50:41 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 46.000000
07-01 15:50:41 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 180.000000
07-01 15:50:41 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2440.000000
07-01 15:50:41 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 23.000000
07-01 15:50:41 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2404.000000
07-01 15:50:41 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 765.000000
07-01 15:50:41 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:50:41 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 13.000000
07-01 15:50:41 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 764.000000
07-01 15:50:41 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 73.000000
07-01 15:50:41 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 15.000000
07-01 15:50:41 I/MeasurementPrinter:                    73.0	                OK	                 3169.0	                OK	                            765.0	                OK
07-01 15:50:41 D/RunUtil: Running command null without timeout.
07-01 15:50:41 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:41 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:41 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:41 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:42 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:42 D/RunUtil: Running command null without timeout.
07-01 15:50:42 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:42 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:42 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:50:42 D/RunUtil: Running command null without timeout.
07-01 15:50:42 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:42 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:42 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:50:42 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:50:42 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:50:42 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:50:43 D/RunUtil: Running command null without timeout.
07-01 15:50:43 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:44 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:50:44 D/RunUtil: Running command null without timeout.
07-01 15:50:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:44 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:44 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:50:44 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:44 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_13869322492584433051.txt] without timeout.
07-01 15:50:45 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:50:45 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:50:45 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:50:45 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:50:55 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:55 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:50:55 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 2996.000000
07-01 15:50:55 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 737.000000
07-01 15:50:55 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 272.000000
07-01 15:50:55 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 91.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 7.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 4.000000
07-01 15:50:55 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 233.000000
07-01 15:50:55 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2376.000000
07-01 15:50:55 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 28.000000
07-01 15:50:55 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 81.000000
07-01 15:50:55 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2255.000000
07-01 15:50:55 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 742.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 8.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 20.000000
07-01 15:50:55 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 21.000000
07-01 15:50:55 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 738.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 42.000000
07-01 15:50:55 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 82.000000
07-01 15:50:55 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:50:55 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:50:55 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:55 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:50:55 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 2996.000000
07-01 15:50:55 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 737.000000
07-01 15:50:55 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 272.000000
07-01 15:50:55 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 91.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 7.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 4.000000
07-01 15:50:55 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 233.000000
07-01 15:50:55 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2376.000000
07-01 15:50:55 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 28.000000
07-01 15:50:55 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 81.000000
07-01 15:50:55 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2255.000000
07-01 15:50:55 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:50:55 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 742.000000
07-01 15:50:55 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 8.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 20.000000
07-01 15:50:55 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 21.000000
07-01 15:50:55 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 738.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 42.000000
07-01 15:50:55 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 82.000000
07-01 15:50:55 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:50:55 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:55 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:50:55 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 2996.000000
07-01 15:50:55 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 737.000000
07-01 15:50:55 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 272.000000
07-01 15:50:55 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 91.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 7.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 4.000000
07-01 15:50:55 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 233.000000
07-01 15:50:55 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2376.000000
07-01 15:50:55 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 28.000000
07-01 15:50:55 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 81.000000
07-01 15:50:55 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2255.000000
07-01 15:50:55 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 742.000000
07-01 15:50:55 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 8.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 20.000000
07-01 15:50:55 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 21.000000
07-01 15:50:55 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 738.000000
07-01 15:50:55 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 42.000000
07-01 15:50:55 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 82.000000
07-01 15:50:55 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:50:55 I/MeasurementPrinter:                    82.0	                OK	                 2997.0	                OK	                            742.0	                OK
07-01 15:50:55 D/RunUtil: Running command null without timeout.
07-01 15:50:55 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:56 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:56 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:56 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:56 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:56 D/RunUtil: Running command null without timeout.
07-01 15:50:56 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:57 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:57 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:50:57 D/RunUtil: Running command null without timeout.
07-01 15:50:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:57 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:50:57 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:50:57 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:50:57 I/NativeDeviceStateMonitor: Waiting 359903 ms for device SKBFXYWR0LWD external store
07-01 15:50:58 D/RunUtil: Running command null without timeout.
07-01 15:50:58 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:58 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:50:58 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:50:58 D/RunUtil: Running command null without timeout.
07-01 15:50:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:50:59 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:50:59 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:50:59 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:50:59 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_12732505889165767394.txt] without timeout.
07-01 15:50:59 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:50:59 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:50:59 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:50:59 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:51:09 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:09 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:51:09 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3074.000000
07-01 15:51:09 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 767.000000
07-01 15:51:09 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 328.000000
07-01 15:51:09 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 14.000000
07-01 15:51:09 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 241.000000
07-01 15:51:09 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2349.000000
07-01 15:51:09 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 6.000000
07-01 15:51:09 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2302.000000
07-01 15:51:09 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 774.000000
07-01 15:51:09 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 10.000000
07-01 15:51:09 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 768.000000
07-01 15:51:09 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 48.000000
07-01 15:51:09 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:51:09 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:51:09 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:09 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:51:09 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3074.000000
07-01 15:51:09 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 767.000000
07-01 15:51:09 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 328.000000
07-01 15:51:09 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 14.000000
07-01 15:51:09 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 241.000000
07-01 15:51:09 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2349.000000
07-01 15:51:09 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 6.000000
07-01 15:51:09 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2302.000000
07-01 15:51:09 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:51:09 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 774.000000
07-01 15:51:09 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:51:09 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 10.000000
07-01 15:51:09 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 768.000000
07-01 15:51:09 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 48.000000
07-01 15:51:09 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:51:09 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:10 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:51:10 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3074.000000
07-01 15:51:10 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 767.000000
07-01 15:51:10 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 328.000000
07-01 15:51:10 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 14.000000
07-01 15:51:10 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 241.000000
07-01 15:51:10 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2349.000000
07-01 15:51:10 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 6.000000
07-01 15:51:10 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2302.000000
07-01 15:51:10 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 774.000000
07-01 15:51:10 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:51:10 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 10.000000
07-01 15:51:10 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 768.000000
07-01 15:51:10 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 48.000000
07-01 15:51:10 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 29.000000
07-01 15:51:10 I/MeasurementPrinter:                    48.0	                OK	                 3076.0	                OK	                            774.0	                OK
07-01 15:51:10 D/RunUtil: Running command null without timeout.
07-01 15:51:10 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:10 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:51:10 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:10 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:11 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:51:11 D/RunUtil: Running command null without timeout.
07-01 15:51:11 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:11 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:11 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:51:11 D/RunUtil: Running command null without timeout.
07-01 15:51:11 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:11 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:11 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:51:11 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYWR0LWD boot complete
07-01 15:51:11 I/DeviceStateMonitor: Waiting 359958 ms for device SKBFXYWR0LWD package manager
07-01 15:51:11 I/NativeDeviceStateMonitor: Waiting 359896 ms for device SKBFXYWR0LWD external store
07-01 15:51:12 D/RunUtil: Running command null without timeout.
07-01 15:51:12 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:12 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:12 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:51:12 D/RunUtil: Running command null without timeout.
07-01 15:51:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:13 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:51:13 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:51:13 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:13 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_1065430848438391629.txt] without timeout.
07-01 15:51:13 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:51:13 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:51:13 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:51:13 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:51:23 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:24 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:51:24 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3073.000000
07-01 15:51:24 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 803.000000
07-01 15:51:24 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 34.000000
07-01 15:51:24 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 288.000000
07-01 15:51:24 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 54.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:51:24 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 148.000000
07-01 15:51:24 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2318.000000
07-01 15:51:24 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 27.000000
07-01 15:51:24 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 69.000000
07-01 15:51:24 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2263.000000
07-01 15:51:24 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 811.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 16.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 11.000000
07-01 15:51:24 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 10.000000
07-01 15:51:24 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 804.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 38.000000
07-01 15:51:24 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 72.000000
07-01 15:51:24 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:51:24 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
07-01 15:51:24 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:24 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:51:24 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3073.000000
07-01 15:51:24 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 803.000000
07-01 15:51:24 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 34.000000
07-01 15:51:24 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 288.000000
07-01 15:51:24 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 54.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:51:24 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 148.000000
07-01 15:51:24 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2318.000000
07-01 15:51:24 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 27.000000
07-01 15:51:24 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 69.000000
07-01 15:51:24 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2263.000000
07-01 15:51:24 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:51:24 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 811.000000
07-01 15:51:24 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 16.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 11.000000
07-01 15:51:24 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 10.000000
07-01 15:51:24 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 804.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 38.000000
07-01 15:51:24 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 72.000000
07-01 15:51:24 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
07-01 15:51:24 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:24 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:51:24 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3073.000000
07-01 15:51:24 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 803.000000
07-01 15:51:24 D/ProtoMeasurementBase: searchbar_state_idle: size = 2, sum: 34.000000
07-01 15:51:24 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 288.000000
07-01 15:51:24 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 54.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 3.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:51:24 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 148.000000
07-01 15:51:24 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2318.000000
07-01 15:51:24 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 27.000000
07-01 15:51:24 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 69.000000
07-01 15:51:24 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2263.000000
07-01 15:51:24 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 811.000000
07-01 15:51:24 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 16.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 11.000000
07-01 15:51:24 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 10.000000
07-01 15:51:24 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 804.000000
07-01 15:51:24 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 38.000000
07-01 15:51:24 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 72.000000
07-01 15:51:24 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 20.000000
07-01 15:51:24 I/MeasurementPrinter:                    72.0	                OK	                 3074.0	                OK	                            811.0	                OK
07-01 15:51:24 D/RunUtil: Running command null without timeout.
07-01 15:51:24 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:25 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:51:25 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:25 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:51:25 D/RunUtil: Running command null without timeout.
07-01 15:51:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:25 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:51:25 D/RunUtil: Running command null without timeout.
07-01 15:51:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:26 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:26 I/NativeDeviceStateMonitor: Device SKBFXYWR0LWD is already ONLINE
07-01 15:51:26 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYWR0LWD boot complete
07-01 15:51:26 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYWR0LWD package manager
07-01 15:51:26 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYWR0LWD external store
07-01 15:51:27 D/RunUtil: Running command null without timeout.
07-01 15:51:27 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:27 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:27 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:51:27 D/RunUtil: Running command null without timeout.
07-01 15:51:27 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:27 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:27 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:28 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:51:28 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, logcat, -c, -b, all] with timeout: 2m 0s
07-01 15:51:28 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:28 D/RunUtil: Running command [/bin/bash, -c, rm -f /data/tmp/e6359ee9-b86f-4f25-9ef6-5e9566226514/tmp/katniss-primes-2024-06-30T23_46_47.991_17306233599718652842.txt] without timeout.
07-01 15:51:28 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
07-01 15:51:28 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
07-01 15:51:28 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
07-01 15:51:28 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, instrument, -e, class, com.google.android.assistant.tvts.NormalDeviceUsageTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
07-01 15:51:38 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:38 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
07-01 15:51:38 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3152.000000
07-01 15:51:38 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 761.000000
07-01 15:51:38 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 281.000000
07-01 15:51:38 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 26.000000
07-01 15:51:38 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
07-01 15:51:38 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:51:38 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 135.000000
07-01 15:51:38 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2442.000000
07-01 15:51:38 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
07-01 15:51:38 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 42.000000
07-01 15:51:38 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2387.000000
07-01 15:51:38 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 762.000000
07-01 15:51:38 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
07-01 15:51:38 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
07-01 15:51:38 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 18.000000
07-01 15:51:38 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 761.000000
07-01 15:51:38 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 31.000000
07-01 15:51:38 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 44.000000
07-01 15:51:38 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
07-01 15:51:38 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 19.000000
07-01 15:51:38 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:38 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
07-01 15:51:38 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3152.000000
07-01 15:51:38 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 761.000000
07-01 15:51:38 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 281.000000
07-01 15:51:38 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 26.000000
07-01 15:51:38 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
07-01 15:51:38 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:51:38 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 135.000000
07-01 15:51:38 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2442.000000
07-01 15:51:38 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
07-01 15:51:38 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 42.000000
07-01 15:51:38 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2387.000000
07-01 15:51:38 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
07-01 15:51:38 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 762.000000
07-01 15:51:38 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:51:38 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
07-01 15:51:38 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
07-01 15:51:38 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 18.000000
07-01 15:51:38 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 761.000000
07-01 15:51:38 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 31.000000
07-01 15:51:38 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 44.000000
07-01 15:51:38 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 19.000000
07-01 15:51:38 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:39 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
07-01 15:51:39 D/ProtoMeasurementBase: e2e_text_response: size = 1, sum: 3152.000000
07-01 15:51:39 D/ProtoMeasurementBase: new_result_displayed_text_warm: size = 1, sum: 761.000000
07-01 15:51:39 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 281.000000
07-01 15:51:39 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 26.000000
07-01 15:51:39 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 2.000000
07-01 15:51:39 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
07-01 15:51:39 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 135.000000
07-01 15:51:39 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2442.000000
07-01 15:51:39 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
07-01 15:51:39 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 42.000000
07-01 15:51:39 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2387.000000
07-01 15:51:39 D/ProtoMeasurementBase: result_displayed_text: size = 1, sum: 762.000000
07-01 15:51:39 D/ProtoMeasurementBase: Adding required latency: result_displayed_text
07-01 15:51:39 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
07-01 15:51:39 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
07-01 15:51:39 D/ProtoMeasurementBase: view_add_text: size = 1, sum: 18.000000
07-01 15:51:39 D/ProtoMeasurementBase: e2e_client_text_response: size = 1, sum: 761.000000
07-01 15:51:39 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 31.000000
07-01 15:51:39 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 44.000000
07-01 15:51:39 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 19.000000
07-01 15:51:39 I/MeasurementPrinter:                    44.0	                OK	                 3149.0	                OK	                            762.0	                OK
07-01 15:51:39 D/RunUtil: Running command null without timeout.
07-01 15:51:39 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:39 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:51:39 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:39 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:40 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
07-01 15:51:40 D/RunUtil: Running command null without timeout.
07-01 15:51:40 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:40 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
07-01 15:51:40 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
07-01 15:51:40 D/RunUtil: Running command null without timeout.
07-01 15:51:40 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:40 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
07-01 15:51:40 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.katniss
07-01 15:51:40 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, am, force-stop, com.google.android.katniss] with timeout: 2m 0s
07-01 15:51:40 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:40 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:41 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:41 D/NativeDevice: Using property ro.build.version.sdk=29 from cache.
07-01 15:51:41 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, getprop, ro.config.low_ram] with timeout: 45s
07-01 15:51:41 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, pm, list, features] with timeout: 2m 0s
07-01 15:51:41 W/TestDevice: Feature: feature:com.google.android.feature.AMATI_EXPERIENCE is not available on SKBFXYWR0LWD
07-01 15:51:41 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, getprop, ro.config.low_ram] with timeout: 45s
07-01 15:51:41 D/RunUtil: Running command [adb, -s, SKBFXYWR0LWD, shell, pm, list, features] with timeout: 2m 0s
07-01 15:51:41 W/TestDevice: Feature: feature:com.google.android.feature.AMATI_EXPERIENCE is not available on SKBFXYWR0LWD
07-01 15:51:41 I/BasicAggregationTypeBase: Checking if collection is initialized with data
07-01 15:51:41 I/BasicAggregationTypeBase: Checking if collection is initialized with data
07-01 15:51:41 D/PrettyTestEventLogger: 
==================== com.google.android.assistant.v4.tvts.TvtsAssistant4Test#testNormalDeviceUsage ENDED: Mon Jul 01 15:51:41 KST 2024 ====================
